<html>
 <head>
  <meta charset="UTF-8">
 </head>
 <body>
  <h3 data-lake-id="0b479686" id="0b479686"><span data-lake-id="uc012dcce" id="uc012dcce">问题发现</span></h3>
  <p data-lake-id="ube994fb9" id="ube994fb9"><br></p>
  <p data-lake-id="uac9e4795" id="uac9e4795"><span data-lake-id="ua0fdeac8" id="ua0fdeac8">本文整理自一个真实的案例，在一次大促之前的压测时发现了这个问题。</span></p>
  <p data-lake-id="u7b486c34" id="u7b486c34"><br></p>
  <p data-lake-id="ucdc60e96" id="ucdc60e96"><span data-lake-id="udaa3f152" id="udaa3f152">在每次大促之前，我们的测试人员都会对网站进行压力测试，这个时候会查看服务的cpu、内存、load、rt、qps等指标。</span></p>
  <p data-lake-id="uf18e0aae" id="uf18e0aae"><br></p>
  <p data-lake-id="u64fdd1bd" id="u64fdd1bd"><span data-lake-id="u53eadde6" id="u53eadde6">在一次压测过程中，测试人员发现我们的某一个接口，在qps上升到500以后，CPU使用率急剧升高。</span></p>
  <p data-lake-id="u45636476" id="u45636476"><br></p>
  <blockquote data-lake-id="ua4fdb224" id="ua4fdb224">
   <p data-lake-id="uab01e42c" id="uab01e42c"><span data-lake-id="u245a05da" id="u245a05da">CPU利用率，又称CPU使用率。顾名思义，CPU利用率是来描述CPU的使用情况的，表明了一段时间内CPU被占用的情况。使用率越高，说明你的机器在这个时间上运行了很多程序，反之较少。</span></p>
  </blockquote>
  <p data-lake-id="u817376e0" id="u817376e0"><br></p>
  <h3 data-lake-id="4e091815" id="4e091815"><span data-lake-id="u95e2c368" id="u95e2c368">问题定位</span></h3>
  <p data-lake-id="u0427f663" id="u0427f663"><br></p>
  <p data-lake-id="ubee700ba" id="ubee700ba"><span data-lake-id="uce0fa7df" id="uce0fa7df">遇到这种问题，首先是登录到服务器，看一下具体情况。</span></p>
  <p data-lake-id="ua06370f7" id="ua06370f7"><br></p>
  <p data-lake-id="ub5c047a1" id="ub5c047a1"><strong><span data-lake-id="ufee8bb30" id="ufee8bb30">定位进程</span></strong></p>
  <p data-lake-id="ue55f59e2" id="ue55f59e2"><br></p>
  <p data-lake-id="u2787219c" id="u2787219c"><span data-lake-id="uc9bb39a9" id="uc9bb39a9">登录服务器，执行top命令，查看CPU占用情况：</span></p>
  <p data-lake-id="ub13d04de" id="ub13d04de"><br></p>
  <pre lang="java"><code>
$top
   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
  1893 admin     20   0 7127m 2.6g  38m S 181.7 32.6  10:20.26 java
</code></pre>
  <p data-lake-id="u80c04df8" id="u80c04df8"><br></p>
  <blockquote data-lake-id="uac3e7b6f" id="uac3e7b6f">
   <p data-lake-id="u3d55438b" id="u3d55438b"><span data-lake-id="u06b7e21a" id="u06b7e21a">top命令是Linux下常用的性能分析工具，能够实时显示系统中各个进程的资源占用状况，类似于Windows的任务管理器。</span></p>
  </blockquote>
  <p data-lake-id="ue1821e12" id="ue1821e12"><br></p>
  <p data-lake-id="u379c66bf" id="u379c66bf"><span data-lake-id="u181d23f6" id="u181d23f6">通过以上命令，我们可以看到，进程ID为1893的Java进程的CPU占用率达到了181%，基本可以定位到是我们的Java应用导致整个服务器的CPU占用率飙升。</span></p>
  <p data-lake-id="u3e440c23" id="u3e440c23"><br></p>
  <p data-lake-id="ua0baa8b7" id="ua0baa8b7"><strong><span data-lake-id="u28131e18" id="u28131e18">定位线程</span></strong></p>
  <p data-lake-id="u8aff328c" id="u8aff328c"><br></p>
  <p data-lake-id="u4e62d388" id="u4e62d388"><span data-lake-id="u1bb696c0" id="u1bb696c0">我们知道，Java是单进程多线程的，那么，我们接下来看看PID=1893的这个Java进程中的各个线程的CPU使用情况，同样是用top命令：</span></p>
  <p data-lake-id="u384edcd5" id="u384edcd5"><br></p>
  <pre lang="java"><code>
$top -Hp 1893
   PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
  4519 admin     20   0 7127m 2.6g  38m R 18.6 32.6   0:40.11 java
</code></pre>
  <p data-lake-id="udae8db12" id="udae8db12"><br></p>
  <p data-lake-id="ue8d18fb7" id="ue8d18fb7"><span data-lake-id="u32369462" id="u32369462">通过top -Hp 1893命令，我们可以发现，当前1893这个进程中，ID为4519的线程占用CPU最高。</span></p>
  <p data-lake-id="u9124b58f" id="u9124b58f"><br></p>
  <p data-lake-id="u3e5a554c" id="u3e5a554c"><strong><span data-lake-id="u0ae99b42" id="u0ae99b42">定位代码</span></strong></p>
  <p data-lake-id="ude1249a6" id="ude1249a6"><br></p>
  <p data-lake-id="uc3eccd0a" id="uc3eccd0a"><span data-lake-id="u7597d95f" id="u7597d95f">通过top命令，我们目前已经定位到导致CPU使用率较高的具体线程， 那么我么接下来就定位下到底是哪一行代码存在问题。</span></p>
  <p data-lake-id="uc7cf6947" id="uc7cf6947"><br></p>
  <p data-lake-id="u2be44e89" id="u2be44e89"><span data-lake-id="u11c6fb16" id="u11c6fb16">首先，我们需要把4519这个线程转成16进制：</span></p>
  <p data-lake-id="uf8fb62da" id="uf8fb62da"><br></p>
  <pre lang="java"><code>
$printf  '%x\n'  4519
11a7
</code></pre>
  <p data-lake-id="ue3d64a72" id="ue3d64a72"><br></p>
  <p data-lake-id="ud87b243f" id="ud87b243f"><span data-lake-id="u42321778" id="u42321778">接下来，通过jstack命令，查看栈信息：</span></p>
  <p data-lake-id="u7e7f8146" id="u7e7f8146"><br></p>
  <pre lang="java"><code>
$sudo -u admin  jstack 1893 |grep -A 200 11a7
"HSFBizProcessor-DEFAULT-8-thread-5" #500 daemon prio=10 os_prio=0 tid=0x00007f632314a800 nid=0x11a2 runnable [0x000000005442a000]
   java.lang.Thread.State: RUNNABLE
  at sun.misc.URLClassPath$Loader.findResource(URLClassPath.java:684)
  at sun.misc.URLClassPath.findResource(URLClassPath.java:188)
  at java.net.URLClassLoader$2.run(URLClassLoader.java:569)
  at java.net.URLClassLoader$2.run(URLClassLoader.java:567)
  at java.security.AccessController.doPrivileged(Native Method)
  at java.net.URLClassLoader.findResource(URLClassLoader.java:566)
  at java.lang.ClassLoader.getResource(ClassLoader.java:1093)
  at java.net.URLClassLoader.getResourceAsStream(URLClassLoader.java:232)
  at org.hibernate.validator.internal.xml.ValidationXmlParser.getInputStreamForPath(ValidationXmlParser.java:248)
  at org.hibernate.validator.internal.xml.ValidationXmlParser.getValidationConfig(ValidationXmlParser.java:191)
  at org.hibernate.validator.internal.xml.ValidationXmlParser.parseValidationXml(ValidationXmlParser.java:65)
  at org.hibernate.validator.internal.engine.ConfigurationImpl.parseValidationXml(ConfigurationImpl.java:287)
  at org.hibernate.validator.internal.engine.ConfigurationImpl.buildValidatorFactory(ConfigurationImpl.java:174)
  at javax.validation.Validation.buildDefaultValidatorFactory(Validation.java:111)
  at com.test.common.util.BeanValidator.validate(BeanValidator.java:30)
</code></pre>
  <p data-lake-id="uf0f5c795" id="uf0f5c795"><br></p>
  <p data-lake-id="u79f25c57" id="u79f25c57"><span data-lake-id="uf136f05d" id="uf136f05d">通过以上代码，我们可以清楚的看到，BeanValidator.java的第30行是有可能存在问题的。</span></p>
  <p data-lake-id="ua503585d" id="ua503585d"><br></p>
  <h3 data-lake-id="520f9e6c" id="520f9e6c"><span data-lake-id="u2b624e10" id="u2b624e10">问题解决</span></h3>
  <p data-lake-id="u794dc468" id="u794dc468"><br></p>
  <p data-lake-id="u547fdb1d" id="u547fdb1d"><span data-lake-id="u07f4934d" id="u07f4934d">接下来就是通过查看代码来解决问题了，我们发现，我们自定义了一个BeanValidator，封装了Hibernate的Validator，然后在validate方法中，通过Validation.buildDefaultValidatorFactory().getValidator()初始化一个Validator实例，通过分析发现这个实例化的过程比较耗时。</span></p>
  <p data-lake-id="uf5e85dbb" id="uf5e85dbb"><br></p>
  <p data-lake-id="uacca99bf" id="uacca99bf"><span data-lake-id="ub38ccd7d" id="ub38ccd7d">我们重构了一下代码，把Validator实例的初始化提到方法外，在类初始化的时候创建一次就解决了问题。</span></p>
  <p data-lake-id="uef101b80" id="uef101b80"><br></p>
  <h3 data-lake-id="25f9c7fa" id="25f9c7fa"><span data-lake-id="u79850867" id="u79850867">总结</span></h3>
  <p data-lake-id="u146db90e" id="u146db90e"><br></p>
  <p data-lake-id="u9f389409" id="u9f389409"><span data-lake-id="u89be76ba" id="u89be76ba">以上，展示了一次比较完成的线上问题定位过程。主要用到的命令有:top 、printf 和 jstack</span></p>
  <p data-lake-id="u3d3cf036" id="u3d3cf036"><br></p>
  <p data-lake-id="u29314e2f" id="u29314e2f"><span data-lake-id="u58ad4ad5" id="u58ad4ad5">另外，线上问题排查还可以使用Alibaba开源的工具Arthas进行排查，以上问题，可以使用以下命令定位：</span></p>
  <p data-lake-id="u79419814" id="u79419814"><br></p>
  <pre lang="java"><code>
thread -n 3 //查看cpu占比前三的线程
</code></pre>
  <p data-lake-id="u4c9fd9b2" id="u4c9fd9b2"><br></p>
  <p data-lake-id="u6575704f" id="u6575704f"><span data-lake-id="u2f717121" id="u2f717121">以上，本文介绍了如何排查线上服务器CPU使用率过高的问题，如果大家感兴趣，后面可以再介绍一些关于LOAD飙高、频繁GC等问题的排查手段。</span></p>
 </body>
</html>